pcsx2/common/Console.cpp

510 lines
13 KiB
C++

// SPDX-FileCopyrightText: 2002-2024 PCSX2 Dev Team
// SPDX-License-Identifier: GPL-3.0+
#include "common/Console.h"
#include "common/Assertions.h"
#include "common/FileSystem.h"
#include "common/SmallString.h"
#include "common/Timer.h"
#include "fmt/format.h"
#include <mutex>
#include <vector>
#ifdef _WIN32
#include "common/RedtapeWindows.h"
#else
#include <unistd.h>
#endif
using namespace std::string_view_literals;
// Dummy objects, need to get rid of them...
ConsoleLogWriter<LOGLEVEL_INFO> Console;
ConsoleLogWriter<LOGLEVEL_DEV> DevCon;
#ifdef _DEBUG
ConsoleLogWriter<LOGLEVEL_DEBUG> DbgConWriter;
#else
NullLogWriter DbgConWriter;
#endif
#define TIMESTAMP_FORMAT_STRING "[{:10.4f}] "
#define TIMESTAMP_PRINTF_STRING "[%10.4f] "
namespace Log
{
static void WriteToConsole(LOGLEVEL level, ConsoleColors color, std::string_view message);
static void WriteToDebug(LOGLEVEL level, ConsoleColors color, std::string_view message);
static void WriteToFile(LOGLEVEL level, ConsoleColors color, std::string_view message);
static void UpdateMaxLevel();
static void ExecuteCallbacks(LOGLEVEL level, ConsoleColors color, std::string_view message);
static Common::Timer::Value s_start_timestamp = Common::Timer::GetCurrentValue();
static LOGLEVEL s_max_level = LOGLEVEL_NONE;
static LOGLEVEL s_console_level = LOGLEVEL_NONE;
static LOGLEVEL s_debug_level = LOGLEVEL_NONE;
static LOGLEVEL s_file_level = LOGLEVEL_NONE;
static LOGLEVEL s_host_level = LOGLEVEL_NONE;
static bool s_log_timestamps = true;
static FileSystem::ManagedCFilePtr s_file_handle;
static std::string s_file_path;
static std::mutex s_file_mutex;
static HostCallbackType s_host_callback;
#ifdef _WIN32
static HANDLE s_hConsoleStdIn = NULL;
static HANDLE s_hConsoleStdOut = NULL;
static HANDLE s_hConsoleStdErr = NULL;
#endif
} // namespace Log
float Log::GetCurrentMessageTime()
{
return static_cast<float>(Common::Timer::ConvertValueToSeconds(Common::Timer::GetCurrentValue() - s_start_timestamp));
}
__ri void Log::WriteToConsole(LOGLEVEL level, ConsoleColors color, std::string_view message)
{
static constexpr std::string_view s_ansi_color_codes[ConsoleColors_Count] = {
"\033[0m"sv, // default
"\033[30m\033[1m"sv, // black
"\033[32m"sv, // green
"\033[31m"sv, // red
"\033[34m"sv, // blue
"\033[35m"sv, // magenta
"\033[35m"sv, // orange (FIXME)
"\033[37m"sv, // gray
"\033[36m"sv, // cyan
"\033[33m"sv, // yellow
"\033[37m"sv, // white
"\033[30m\033[1m"sv, // strong black
"\033[31m\033[1m"sv, // strong red
"\033[32m\033[1m"sv, // strong green
"\033[34m\033[1m"sv, // strong blue
"\033[35m\033[1m"sv, // strong magenta
"\033[35m\033[1m"sv, // strong orange (FIXME)
"\033[37m\033[1m"sv, // strong gray
"\033[36m\033[1m"sv, // strong cyan
"\033[33m\033[1m"sv, // strong yellow
"\033[37m\033[1m"sv, // strong white
};
static constexpr size_t BUFFER_SIZE = 512;
SmallStackString<BUFFER_SIZE> buffer;
buffer.reserve(32 + message.length());
buffer.append(s_ansi_color_codes[color]);
if (s_log_timestamps)
buffer.append_format(TIMESTAMP_FORMAT_STRING, Log::GetCurrentMessageTime());
buffer.append(message);
buffer.append('\n');
#ifdef _WIN32
const HANDLE hOutput = (level <= LOGLEVEL_WARNING) ? s_hConsoleStdErr : s_hConsoleStdOut;
// Convert to UTF-16 first so Unicode characters display correctly. NT is going to do it anyway...
wchar_t wbuf[BUFFER_SIZE];
wchar_t* wmessage_buf = wbuf;
int wmessage_buflen = static_cast<int>(std::size(wbuf) - 1);
if (buffer.length() >= std::size(wbuf))
{
wmessage_buflen = static_cast<int>(buffer.length());
wmessage_buf = static_cast<wchar_t*>(std::malloc(static_cast<size_t>(wmessage_buflen) * sizeof(wchar_t)));
if (!wmessage_buf)
return;
}
const int wmessage_size = MultiByteToWideChar(CP_UTF8, 0, buffer.data(), static_cast<int>(buffer.length()), wmessage_buf, wmessage_buflen);
if (wmessage_size <= 0)
goto cleanup;
DWORD chars_written;
WriteConsoleW(hOutput, wmessage_buf, static_cast<DWORD>(wmessage_size), &chars_written, nullptr);
cleanup:
if (wmessage_buf != wbuf)
std::free(wmessage_buf);
#else
const int fd = (level <= LOGLEVEL_WARNING) ? STDERR_FILENO : STDOUT_FILENO;
write(fd, buffer.data(), buffer.length());
#endif
}
bool Log::IsConsoleOutputEnabled()
{
return (s_console_level > LOGLEVEL_NONE);
}
void Log::SetConsoleOutputLevel(LOGLEVEL level)
{
if (s_console_level == level)
return;
const bool was_enabled = (s_console_level > LOGLEVEL_NONE);
const bool now_enabled = (level > LOGLEVEL_NONE);
s_console_level = level;
UpdateMaxLevel();
if (was_enabled == now_enabled)
return;
// Worst that happens here is we write to a bad handle..
#if defined(_WIN32)
static constexpr auto enable_virtual_terminal_processing = [](HANDLE hConsole) {
DWORD old_mode;
if (!GetConsoleMode(hConsole, &old_mode))
return;
// already enabled?
if (old_mode & ENABLE_VIRTUAL_TERMINAL_PROCESSING)
return;
SetConsoleMode(hConsole, old_mode | ENABLE_VIRTUAL_TERMINAL_PROCESSING);
};
// On windows, no console is allocated by default on a windows based application
static bool console_was_allocated = false;
static HANDLE old_stdin = NULL;
static HANDLE old_stdout = NULL;
static HANDLE old_stderr = NULL;
if (now_enabled)
{
old_stdin = GetStdHandle(STD_INPUT_HANDLE);
old_stdout = GetStdHandle(STD_OUTPUT_HANDLE);
old_stderr = GetStdHandle(STD_ERROR_HANDLE);
if (!old_stdout)
{
// Attach to the parent console if we're running from a command window
if (!AttachConsole(ATTACH_PARENT_PROCESS) && !AllocConsole())
return;
s_hConsoleStdIn = GetStdHandle(STD_INPUT_HANDLE);
s_hConsoleStdOut = GetStdHandle(STD_OUTPUT_HANDLE);
s_hConsoleStdErr = GetStdHandle(STD_ERROR_HANDLE);
enable_virtual_terminal_processing(s_hConsoleStdOut);
enable_virtual_terminal_processing(s_hConsoleStdErr);
std::FILE* fp;
freopen_s(&fp, "CONIN$", "r", stdin);
freopen_s(&fp, "CONOUT$", "w", stdout);
freopen_s(&fp, "CONOUT$", "w", stderr);
console_was_allocated = true;
}
else
{
s_hConsoleStdIn = old_stdin;
s_hConsoleStdOut = old_stdout;
s_hConsoleStdErr = old_stderr;
}
}
else
{
if (console_was_allocated)
{
console_was_allocated = false;
std::FILE* fp;
freopen_s(&fp, "NUL:", "w", stderr);
freopen_s(&fp, "NUL:", "w", stdout);
freopen_s(&fp, "NUL:", "w", stdin);
SetStdHandle(STD_ERROR_HANDLE, old_stderr);
SetStdHandle(STD_OUTPUT_HANDLE, old_stdout);
SetStdHandle(STD_INPUT_HANDLE, old_stdin);
s_hConsoleStdIn = NULL;
s_hConsoleStdOut = NULL;
s_hConsoleStdErr = NULL;
FreeConsole();
}
}
#endif
}
__ri void Log::WriteToDebug(LOGLEVEL level, ConsoleColors color, std::string_view message)
{
#ifdef _WIN32
static constexpr size_t BUFFER_SIZE = 512;
// Convert to UTF-16 first so Unicode characters display correctly. NT is going to do it anyway...
wchar_t wbuf[BUFFER_SIZE];
wchar_t* wmessage_buf = wbuf;
int wmessage_buflen = static_cast<int>(std::size(wbuf) - 1);
if (message.length() >= std::size(wbuf))
{
wmessage_buflen = static_cast<int>(message.length());
wmessage_buf = static_cast<wchar_t*>(std::malloc((static_cast<size_t>(wmessage_buflen) + 2) * sizeof(wchar_t)));
if (!wmessage_buf)
return;
}
int wmessage_size = 0;
if (!message.empty()) [[likely]]
{
wmessage_size = MultiByteToWideChar(CP_UTF8, 0, message.data(), static_cast<int>(message.length()), wmessage_buf, wmessage_buflen);
if (wmessage_size <= 0)
goto cleanup;
}
wmessage_buf[wmessage_size++] = L'\n';
wmessage_buf[wmessage_size++] = 0;
OutputDebugStringW(wmessage_buf);
cleanup:
if (wmessage_buf != wbuf)
std::free(wmessage_buf);
#endif
}
bool Log::IsDebugOutputAvailable()
{
#ifdef _WIN32
return IsDebuggerPresent();
#else
return false;
#endif
}
bool Log::IsDebugOutputEnabled()
{
return (s_console_level > LOGLEVEL_NONE);
}
void Log::SetDebugOutputLevel(LOGLEVEL level)
{
s_debug_level = level;
UpdateMaxLevel();
}
__ri void Log::WriteToFile(LOGLEVEL level, ConsoleColors color, std::string_view message)
{
std::unique_lock lock(s_file_mutex);
if (!s_file_handle) [[unlikely]]
return;
if (!message.empty()) [[likely]]
{
if (s_log_timestamps)
{
std::fprintf(s_file_handle.get(), TIMESTAMP_PRINTF_STRING "%.*s\n", GetCurrentMessageTime(),
static_cast<int>(message.size()), message.data());
}
else
{
std::fprintf(s_file_handle.get(), "%.*s\n", static_cast<int>(message.size()), message.data());
}
}
else
{
if (s_log_timestamps)
{
std::fprintf(s_file_handle.get(), TIMESTAMP_PRINTF_STRING "\n", GetCurrentMessageTime());
}
else
{
std::fputc('\n', s_file_handle.get());
}
}
std::fflush(s_file_handle.get());
}
bool Log::IsFileOutputEnabled()
{
return (s_file_level > LOGLEVEL_NONE);
}
bool Log::SetFileOutputLevel(LOGLEVEL level, std::string path)
{
std::unique_lock lock(s_file_mutex);
const bool was_enabled = (s_file_level > LOGLEVEL_NONE);
const bool new_enabled = (level > LOGLEVEL_NONE && !path.empty());
if (was_enabled != new_enabled || (new_enabled && path == s_file_path))
{
if (new_enabled)
{
if (!s_file_handle || s_file_path != path)
{
s_file_handle.reset();
s_file_handle = FileSystem::OpenManagedCFile(path.c_str(), "wb");
if (s_file_handle)
{
s_file_path = std::move(path);
}
else
{
s_file_path = {};
if (IsConsoleOutputEnabled())
WriteToConsole(LOGLEVEL_ERROR, Color_StrongRed, TinyString::from_format("Failed to open log file '{}'", path));
}
}
}
else
{
s_file_handle.reset();
s_file_path = {};
}
}
s_file_level = s_file_handle ? level : LOGLEVEL_NONE;
return IsFileOutputEnabled();
}
std::FILE* Log::GetFileLogHandle()
{
std::unique_lock lock(s_file_mutex);
return s_file_handle.get();
}
bool Log::IsHostOutputEnabled()
{
return (s_host_level > LOGLEVEL_NONE);
}
void Log::SetHostOutputLevel(LOGLEVEL level, HostCallbackType callback)
{
s_host_callback = callback;
s_host_level = callback ? level : LOGLEVEL_NONE;
UpdateMaxLevel();
}
bool Log::AreTimestampsEnabled()
{
return s_log_timestamps;
}
void Log::SetTimestampsEnabled(bool enabled)
{
s_log_timestamps = enabled;
}
LOGLEVEL Log::GetMaxLevel()
{
return s_max_level;
}
__ri void Log::UpdateMaxLevel()
{
s_max_level = std::max(s_console_level, std::max(s_debug_level, std::max(s_file_level, s_host_level)));
}
void Log::ExecuteCallbacks(LOGLEVEL level, ConsoleColors color, std::string_view message)
{
// TODO: Cache the message time.
// Split newlines into separate messages.
std::string_view::size_type start_pos = 0;
if (std::string_view::size_type end_pos = message.find('\n'); end_pos != std::string::npos) [[unlikely]]
{
for (;;)
{
std::string_view message_line;
if (start_pos != end_pos)
message_line = message.substr(start_pos, (end_pos == std::string_view::npos) ? end_pos : end_pos - start_pos);
ExecuteCallbacks(level, color, message_line);
if (end_pos == std::string_view::npos)
return;
start_pos = end_pos + 1;
end_pos = message.find('\n', start_pos);
}
return;
}
pxAssert(level > LOGLEVEL_NONE);
if (level <= s_console_level)
WriteToConsole(level, color, message);
if (level <= s_debug_level)
WriteToDebug(level, color, message);
if (level <= s_file_level)
WriteToFile(level, color, message);
if (level <= s_host_level)
{
// double check in case of race here
const HostCallbackType callback = s_host_callback;
if (callback)
s_host_callback(level, color, message);
}
}
void Log::Write(LOGLEVEL level, ConsoleColors color, std::string_view message)
{
if (level > s_max_level)
return;
ExecuteCallbacks(level, color, message);
}
void Log::Writef(LOGLEVEL level, ConsoleColors color, const char* format, ...)
{
std::va_list ap;
va_start(ap, format);
Writev(level, color, format, ap);
va_end(ap);
}
void Log::Writev(LOGLEVEL level, ConsoleColors color, const char* format, va_list ap)
{
if (level > s_max_level)
return;
std::va_list ap_copy;
va_copy(ap_copy, ap);
#ifdef _WIN32
const u32 required_size = static_cast<u32>(_vscprintf(format, ap_copy));
#else
const u32 required_size = std::vsnprintf(nullptr, 0, format, ap_copy);
#endif
va_end(ap_copy);
if (required_size < 512)
{
char buffer[512];
const int len = std::vsnprintf(buffer, std::size(buffer), format, ap);
if (len > 0)
ExecuteCallbacks(level, color, std::string_view(buffer, static_cast<size_t>(len)));
}
else
{
char* buffer = new char[required_size + 1];
const int len = std::vsnprintf(buffer, required_size + 1, format, ap);
if (len > 0)
ExecuteCallbacks(level, color, std::string_view(buffer, static_cast<size_t>(len)));
delete[] buffer;
}
}
void Log::WriteFmtArgs(LOGLEVEL level, ConsoleColors color, fmt::string_view fmt, fmt::format_args args)
{
if (level > s_max_level)
return;
fmt::memory_buffer buffer;
fmt::vformat_to(std::back_inserter(buffer), fmt, args);
ExecuteCallbacks(level, color, std::string_view(buffer.data(), buffer.size()));
}