Common/Log: Restore old console behavior

This commit is contained in:
Connor McLaughlin 2021-07-29 13:45:11 +10:00
parent b8bd545ee9
commit 26a8f8d9e7

View file

@ -11,7 +11,6 @@
#include "windows_headers.h" #include "windows_headers.h"
#elif defined(__ANDROID__) #elif defined(__ANDROID__)
#include <android/log.h> #include <android/log.h>
#include <unistd.h>
#else #else
#include <unistd.h> #include <unistd.h>
#endif #endif
@ -130,193 +129,81 @@ static void FormatLogMessageForDisplay(const char* channelName, const char* func
printCallback(message, pCallbackUserData); printCallback(message, pCallbackUserData);
} }
#if defined(_WIN32) #if defined(WIN32)
// Windows obscures access to POSIX style write() and file handles.
#include <io.h>
#define STDOUT_FILENO (_fileno(stdout))
#define STDERR_FILENO (_fileno(stderr))
#define write(fd, buf, count) _write(fd, buf, (int)count)
#endif
static void StandardOutputLogCallback(void* pUserParam, const char* channelName, const char* functionName, static void ConsoleOutputLogCallback(void* pUserParam, const char* channelName, const char* functionName,
LOGLEVEL level, const char* message) LOGLEVEL level, const char* message)
{ {
if (!s_consoleOutputEnabled || level > s_consoleOutputLevelFilter || if (!s_consoleOutputEnabled || level > s_consoleOutputLevelFilter ||
s_consoleOutputChannelFilter.Find(channelName) >= 0) s_consoleOutputChannelFilter.Find(channelName) >= 0)
return; return;
static const char* const colorCodes[LOGLEVEL_COUNT] = { if (level > LOGLEVEL_COUNT)
"\033[0m", // NONE level = LOGLEVEL_TRACE;
"\033[1;31m", // ERROR
"\033[1;33m", // WARNING
"\033[1;35m", // PERF
"\033[1;37m", // INFO
"\033[1;32m", // VERBOSE
"\033[0;37m", // DEV
"\033[1;36m", // PROFILE
"\033[0;32m", // DEBUG
"\033[0;34m", // TRACE
};
if (int outputFd = (level <= LOGLEVEL_WARNING) ? STDERR_FILENO : STDOUT_FILENO; outputFd >= 0) HANDLE hConsole = GetStdHandle((level <= LOGLEVEL_WARNING) ? STD_ERROR_HANDLE : STD_OUTPUT_HANDLE);
if (hConsole != INVALID_HANDLE_VALUE)
{ {
write(outputFd, colorCodes[level], std::strlen(colorCodes[level])); static const WORD levelColors[LOGLEVEL_COUNT] = {
FOREGROUND_RED | FOREGROUND_BLUE | FOREGROUND_GREEN, // NONE
FOREGROUND_RED | FOREGROUND_INTENSITY, // ERROR
FOREGROUND_RED | FOREGROUND_GREEN | FOREGROUND_INTENSITY, // WARNING
FOREGROUND_RED | FOREGROUND_BLUE | FOREGROUND_INTENSITY, // PERF
FOREGROUND_RED | FOREGROUND_BLUE | FOREGROUND_GREEN | FOREGROUND_INTENSITY, // INFO
FOREGROUND_GREEN | FOREGROUND_INTENSITY, // VERBOSE
FOREGROUND_RED | FOREGROUND_BLUE | FOREGROUND_GREEN, // DEV
FOREGROUND_BLUE | FOREGROUND_GREEN | FOREGROUND_INTENSITY, // PROFILE
FOREGROUND_GREEN, // DEBUG
FOREGROUND_BLUE, // TRACE
};
Log::FormatLogMessageForDisplay( CONSOLE_SCREEN_BUFFER_INFO oldConsoleScreenBufferInfo;
GetConsoleScreenBufferInfo(hConsole, &oldConsoleScreenBufferInfo);
SetConsoleTextAttribute(hConsole, levelColors[level]);
// write message in the formatted way
FormatLogMessageForDisplay(
channelName, functionName, level, message, channelName, functionName, level, message,
[](const char* text, void* outputFd) { write((int)(intptr_t)outputFd, text, std::strlen(text)); }, [](const char* text, void* hConsole) {
(void*)(intptr_t)outputFd); DWORD written;
WriteConsoleA(static_cast<HANDLE>(hConsole), text, static_cast<DWORD>(std::strlen(text)), &written, nullptr);
},
(void*)hConsole);
write(outputFd, colorCodes[0], std::strlen(colorCodes[0])); // write newline
write(outputFd, "\n", 1); DWORD written;
WriteConsoleA(hConsole, "\r\n", 2, &written, nullptr);
// restore color
SetConsoleTextAttribute(hConsole, oldConsoleScreenBufferInfo.wAttributes);
} }
} }
#if defined(_WIN32) static void DebugOutputLogCallback(void* pUserParam, const char* channelName, const char* functionName, LOGLEVEL level,
static bool s_msw_console_allocated = false; const char* message)
static HANDLE s_msw_prev_stdin = {};
static HANDLE s_msw_prev_stdout = {};
static HANDLE s_msw_prev_stderr = {};
#include <fcntl.h>
static void msw_ReopenStandardPipes()
{ {
if (s_msw_console_allocated) if (!s_debugOutputEnabled || level > s_debugOutputLevelFilter || s_debugOutputChannelFilter.Find(channelName) >= 0)
return; return;
s_msw_console_allocated = true;
// By affecting only unbound pipes, it allows the program to accept input from stdin or honor
// tee of stdout/stderr. Typical use case from GitBash terminal is to use `tee` to filter and pipe
// several different levels of trace into various files, all very neat and fast and not requiring
// any modification to the emulator beyond allowing for basic standard pipe redirection to work in
// the way it was designed to work over 40 yrs ago.
// open outputs as binary to suppress Windows newline corruption (\r mess)
std::FILE* fp;
if (!s_msw_prev_stdin)
{
freopen_s(&fp, "CONIN$", "r", stdin);
}
if (!s_msw_prev_stdout)
{
freopen_s(&fp, "CONOUT$", "wb", stdout);
}
if (!s_msw_prev_stderr)
{
freopen_s(&fp, "CONOUT$", "wb", stderr);
}
// Windows Console Oddities - The only way to get windows built-in console is to render UTF chars from
// the correct alt. fonts is to set either _O_U8TEXT or _O_U16TEXT. However, this imposes a requirement
// that we must write UTF16 to the console using widechar versions of printf and friends (eg, wprintf)...
// EVEN IF YOU WANT TO USE UTF8. Worse, printf() doesn't do the smart thing and assume UTF8 and then
// convert it to UTF16 for us when the output file is in U16TEXT mode. Nope! It throws an ASSERTION and
// forces us to call wprintf, which makes this all totally useless and not cross-platform.
// Lesson: if you want nice UTF font display in your console window, don't use Windows Console.
// Use mintty or conemu instead.
//_setmode(_fileno(stdout), _O_U8TEXT);
//_setmode(_fileno(stderr), _O_U8TEXT);
}
static void msw_FreeLegacyConsole()
{
if (!s_msw_console_allocated)
return;
s_msw_console_allocated = false;
// clear C file handles to the console, otherwise FreeConsole() fails.
std::FILE* fp;
if (!s_msw_prev_stdin)
freopen_s(&fp, "NUL:", "w", stdin);
if (!s_msw_prev_stdout)
freopen_s(&fp, "NUL:", "w", stdout);
if (!s_msw_prev_stderr)
freopen_s(&fp, "NUL:", "w", stderr);
// restore previous handles prior to creating the console.
::SetStdHandle(STD_INPUT_HANDLE, s_msw_prev_stdin);
::SetStdHandle(STD_OUTPUT_HANDLE, s_msw_prev_stdout);
::SetStdHandle(STD_ERROR_HANDLE, s_msw_prev_stderr);
::FreeConsole();
}
static bool msw_AttachLegacyConsole()
{
if (::AttachConsole(ATTACH_PARENT_PROCESS))
return true;
// ERROR_ACCESS_DENIED means a windows Console is already attached.
if (auto err = ::GetLastError(); err == ERROR_ACCESS_DENIED)
{
return true;
}
return false;
}
static bool msw_EnableVirtualTerminalProcessing()
{
HANDLE hConsole = GetStdHandle(STD_OUTPUT_HANDLE);
if (!hConsole)
return false;
DWORD old_mode;
if (!GetConsoleMode(hConsole, &old_mode))
return false;
// already enabled?
if (old_mode & ENABLE_VIRTUAL_TERMINAL_PROCESSING)
return true;
return SetConsoleMode(hConsole, old_mode | ENABLE_VIRTUAL_TERMINAL_PROCESSING);
}
// Creates an old-fashioned console window.
static bool msw_AllocLegacyConsole()
{
// A potentially fancy solution which I haven't had time to experiment with yet is to spawn our own
// terminal application and bind our standard pipes to it, instead of using AllocConsole(). This would
// allow binding to any number of more modern terminal/console apps, all of which handle UTF8 better
// than the windows legacy console (but would also depend on the user having them installed and PATH
// accessible, so definitely not without annoying caveats) --jstine
if (!::AllocConsole())
{
// Console could fail to allocate on an Appveyor/Jenkins environment, for example, because
// when being run as a service the console may be unable to bind itself to a user login session.
// It may also fail if a console is already allocated <-- this is a problem since in this case
// we still want to set
if (auto err = ::GetLastError(); err == ERROR_ACCESS_DENIED)
{
// ERROR_ACCESS_DENIED means a windows Console is already attached.
// whatever the console is, who knows, so let's early-out, and not mess with its font settings.
return true;
}
}
return true;
}
static void msw_DebugOutputLogCallback(void* pUserParam, const char* channelName, const char* functionName,
LOGLEVEL level, const char* message)
{
FormatLogMessageForDisplay( FormatLogMessageForDisplay(
channelName, functionName, level, message, [](const char* text, void*) { OutputDebugStringA(text); }, nullptr); channelName, functionName, level, message, [](const char* text, void*) { OutputDebugStringA(text); }, nullptr);
OutputDebugStringA("\n"); OutputDebugStringA("\n");
} }
#endif
#if defined(__ANDROID__) #elif defined(__ANDROID__)
static void android_DebugOutputLogCallback(void* pUserParam, const char* channelName, const char* functionName,
LOGLEVEL level, const char* message) static void ConsoleOutputLogCallback(void* pUserParam, const char* channelName, const char* functionName,
LOGLEVEL level, const char* message)
{ {
}
static void DebugOutputLogCallback(void* pUserParam, const char* channelName, const char* functionName, LOGLEVEL level,
const char* message)
{
if (!s_debugOutputEnabled || level > s_debugOutputLevelFilter || s_debugOutputChannelFilter.Find(functionName) >= 0)
return;
static const int logPriority[LOGLEVEL_COUNT] = { static const int logPriority[LOGLEVEL_COUNT] = {
ANDROID_LOG_INFO, // NONE ANDROID_LOG_INFO, // NONE
ANDROID_LOG_ERROR, // ERROR ANDROID_LOG_ERROR, // ERROR
@ -332,90 +219,103 @@ static void android_DebugOutputLogCallback(void* pUserParam, const char* channel
__android_log_write(logPriority[level], channelName, message); __android_log_write(logPriority[level], channelName, message);
} }
#endif
#else
static void ConsoleOutputLogCallback(void* pUserParam, const char* channelName, const char* functionName,
LOGLEVEL level, const char* message)
{
if (!s_consoleOutputEnabled || level > s_consoleOutputLevelFilter ||
s_consoleOutputChannelFilter.Find(channelName) >= 0)
return;
static const char* colorCodes[LOGLEVEL_COUNT] = {
"\033[0m", // NONE
"\033[1;31m", // ERROR
"\033[1;33m", // WARNING
"\033[1;35m", // PERF
"\033[1;37m", // INFO
"\033[1;32m", // VERBOSE
"\033[0;37m", // DEV
"\033[1;36m", // PROFILE
"\033[0;32m", // DEBUG
"\033[0;34m", // TRACE
};
int outputFd = (level <= LOGLEVEL_WARNING) ? STDERR_FILENO : STDOUT_FILENO;
write(outputFd, colorCodes[level], std::strlen(colorCodes[level]));
Log::FormatLogMessageForDisplay(
channelName, functionName, level, message,
[](const char* text, void* outputFd) { write((int)(intptr_t)outputFd, text, std::strlen(text)); },
(void*)(intptr_t)outputFd);
write(outputFd, colorCodes[0], std::strlen(colorCodes[0]));
write(outputFd, "\n", 1);
}
static void DebugOutputLogCallback(void* pUserParam, const char* channelName, const char* functionName, LOGLEVEL level, static void DebugOutputLogCallback(void* pUserParam, const char* channelName, const char* functionName, LOGLEVEL level,
const char* message) const char* message)
{ {
if (!s_debugOutputEnabled || level > s_debugOutputLevelFilter || s_debugOutputChannelFilter.Find(channelName) >= 0)
return;
#if defined(_WIN32)
msw_DebugOutputLogCallback(pUserParam, channelName, functionName, level, message);
#endif
#if defined(__ANDROID__)
android_DebugOutputLogCallback(pUserParam, channelName, functionName, level, message);
#endif
} }
#endif
void SetConsoleOutputParams(bool Enabled, const char* ChannelFilter, LOGLEVEL LevelFilter) void SetConsoleOutputParams(bool Enabled, const char* ChannelFilter, LOGLEVEL LevelFilter)
{ {
s_consoleOutputChannelFilter = (ChannelFilter != NULL) ? ChannelFilter : ""; if (s_consoleOutputEnabled != Enabled)
s_consoleOutputLevelFilter = LevelFilter;
if (s_consoleOutputEnabled == Enabled)
return;
s_consoleOutputEnabled = Enabled;
if (Enabled)
RegisterCallback(StandardOutputLogCallback, NULL);
else
UnregisterCallback(StandardOutputLogCallback, NULL);
#if defined(_WIN32) && !defined(_CONSOLE)
if (Enabled)
{ {
// Windows Console behavior is very tricky, and depends on: s_consoleOutputEnabled = Enabled;
// - Whether the application is built with defined(_CONSOLE) or not. if (Enabled)
// - Whether the application is started via a Microsoft shell (Cmd.exe) or a Unix'y shell RegisterCallback(ConsoleOutputLogCallback, NULL);
// (MSYS2, Git Bash, ConEum, ConsoleX, etc) else
// - The instance of the MSVCRT currently in-use, which depends on whether the code is run UnregisterCallback(ConsoleOutputLogCallback, NULL);
// from a DLL and whether that DLL was linked with static or dynamic CRT runtimes.
// - if the DLL uses dynamic CRT, then behavior also depends on whether that dynamic CRT version
// matches the one used by the main program.
//
// To maintain some level of personal sanity, I'll disregard all the DLL/CRT caveats for now.
//
// Console Mode (_CONSOLE) vs Windowed Application
// Microsoft CMD.EXE "does us a favor" and DETACHES the standard console pipes when it spawns
// windowed applications, but only if redirections are not specified at the command line.
// This creates all kinds of confusion and havok that could easy fill pages of the screen with
// comments. The TL;DR version is:
// - only call AllocConsole() if the stdout/stderr pipes are DETACHED (null) - this avoids
// clobbering pipe redirections specified from any shell (cmd/bash) and avoids creating
// spurious console windows when running from MSYS/ConEmu/GitBash.
// - Only use Microsoft's over-engineered Console text-coloring APIs if we called AllocConsole,
// because those APIs result in a whole lot of black screen if you call them while attached to
// a terminal app (ConEmu, ConsoleX, etc).
// - Ignore all of this if defined(_CONSOLE), in that case the OS behavior straightforward and a
// console is always allocated/attached. This is its own annoyance, and thus why few devs use
// it, even for console apps, because actually we DON'T want the console window popping up
// every time we run some console app in the background. --jstine
s_msw_prev_stdin = ::GetStdHandle(STD_INPUT_HANDLE); #if defined(WIN32)
s_msw_prev_stdout = ::GetStdHandle(STD_OUTPUT_HANDLE); // On windows, no console is allocated by default on a windows based application
s_msw_prev_stderr = ::GetStdHandle(STD_ERROR_HANDLE); static bool console_was_allocated = false;
static std::FILE* stdin_fp = nullptr;
if (!s_msw_prev_stdout || !s_msw_prev_stdin) static std::FILE* stdout_fp = nullptr;
static std::FILE* stderr_fp = nullptr;
if (Enabled)
{ {
if (msw_AttachLegacyConsole() || msw_AllocLegacyConsole()) if (GetConsoleWindow() == NULL)
{ {
msw_EnableVirtualTerminalProcessing(); DebugAssert(!console_was_allocated);
msw_ReopenStandardPipes();
// Attach to the parent console if we're running from a command window
if (!AttachConsole(ATTACH_PARENT_PROCESS))
{
if (!AllocConsole())
return;
}
console_was_allocated = true;
std::FILE* fp;
freopen_s(&fp, "CONIN$", "r", stdin);
freopen_s(&fp, "CONOUT$", "w", stdout);
freopen_s(&fp, "CONOUT$", "w", stderr);
} }
} }
else else
{ {
msw_EnableVirtualTerminalProcessing(); if (console_was_allocated)
{
std::FILE* fp;
freopen_s(&fp, "NUL:", "w", stderr);
freopen_s(&fp, "NUL:", "w", stdout);
freopen_s(&fp, "NUL:", "w", stdin);
FreeConsole();
console_was_allocated = false;
}
} }
}
else
{
msw_FreeLegacyConsole();
}
#endif #endif
}
s_consoleOutputChannelFilter = (ChannelFilter != NULL) ? ChannelFilter : "";
s_consoleOutputLevelFilter = LevelFilter;
} }
void SetDebugOutputParams(bool enabled, const char* channelFilter /* = nullptr */, void SetDebugOutputParams(bool enabled, const char* channelFilter /* = nullptr */,