#include "debugging.hpp" #include #include #include #include #include #ifdef _MSC_VER // TODO: why is this necessary? this has /external:I #pragma warning(push) #pragma warning(disable : 4702) #endif #include #ifdef _MSC_VER #pragma warning(pop) #endif #include #include #include #include #ifdef _WIN32 #include #include #include #include #pragma push_macro("FAR") #pragma push_macro("NEAR") #undef FAR #define FAR #undef NEAR #define NEAR #include #pragma pop_macro("NEAR") #pragma pop_macro("FAR") #endif #include namespace Debug { #ifdef _WIN32 bool isRedirected(DWORD nStdHandle) { DWORD fileType = GetFileType(GetStdHandle(nStdHandle)); return (fileType == FILE_TYPE_DISK) || (fileType == FILE_TYPE_PIPE); } bool attachParentConsole() { if (GetConsoleWindow() != nullptr) return true; bool inRedirected = isRedirected(STD_INPUT_HANDLE); bool outRedirected = isRedirected(STD_OUTPUT_HANDLE); bool errRedirected = isRedirected(STD_ERROR_HANDLE); // Note: Do not spend three days reinvestigating this PowerShell bug thinking its our bug. // https://gitlab.com/OpenMW/openmw/-/merge_requests/408#note_447467393 // The handles look valid, but GetFinalPathNameByHandleA can't tell what files they go to and writing to them // doesn't work. if (AttachConsole(ATTACH_PARENT_PROCESS)) { fflush(stdout); fflush(stderr); std::cout.flush(); std::cerr.flush(); // this looks dubious but is really the right way if (!inRedirected) { _wfreopen(L"CON", L"r", stdin); freopen("CON", "r", stdin); std::cin.clear(); } if (!outRedirected) { _wfreopen(L"CON", L"w", stdout); freopen("CON", "w", stdout); std::cout.clear(); } if (!errRedirected) { _wfreopen(L"CON", L"w", stderr); freopen("CON", "w", stderr); std::cerr.clear(); } return true; } return false; } #endif static LogListener logListener; void setLogListener(LogListener listener) { logListener = std::move(listener); } class DebugOutputBase : public boost::iostreams::sink { public: virtual std::streamsize write(const char* str, std::streamsize size) { if (size <= 0) return size; std::string_view msg{ str, static_cast(size) }; // Skip debug level marker Level level = All; if (Log::sWriteLevel) { level = getLevelMarker(msg[0]); msg = msg.substr(1); } char prefix[32]; std::size_t prefixSize; { prefix[0] = '['; const auto now = std::chrono::system_clock::now(); const auto time = std::chrono::system_clock::to_time_t(now); tm time_info{}; #ifdef _WIN32 (void)localtime_s(&time_info, &time); #else (void)localtime_r(&time, &time_info); #endif prefixSize = std::strftime(prefix + 1, sizeof(prefix) - 1, "%T", &time_info) + 1; char levelLetter = " EWIVD*"[int(level)]; const auto ms = std::chrono::duration_cast(now.time_since_epoch()).count(); prefixSize += snprintf(prefix + prefixSize, sizeof(prefix) - prefixSize, ".%03u %c] ", static_cast(ms % 1000), levelLetter); } while (!msg.empty()) { if (msg[0] == 0) break; size_t lineSize = 1; while (lineSize < msg.size() && msg[lineSize - 1] != '\n') lineSize++; writeImpl(prefix, prefixSize, level); writeImpl(msg.data(), lineSize, level); if (logListener) logListener(level, std::string_view(prefix, prefixSize), std::string_view(msg.data(), lineSize)); msg = msg.substr(lineSize); } return size; } virtual ~DebugOutputBase() = default; protected: static Level getLevelMarker(char marker) { if (0 <= marker && static_cast(marker) < static_cast(All)) return static_cast(marker); return All; } virtual std::streamsize writeImpl(const char* str, std::streamsize size, Level debugLevel) { return size; } }; #if defined _WIN32 && defined _DEBUG class DebugOutput : public DebugOutputBase { public: std::streamsize writeImpl(const char* str, std::streamsize size, Level debugLevel) { // Make a copy for null termination std::string tmp(str, static_cast(size)); // Write string to Visual Studio Debug output OutputDebugString(tmp.c_str()); return size; } virtual ~DebugOutput() = default; }; #else namespace { struct Record { std::string mValue; Level mLevel; }; std::deque globalBuffer; Color getColor(Level level) { switch (level) { case Error: return Red; case Warning: return Yellow; case Info: return Reset; case Verbose: return DarkGray; case Debug: return DarkGray; case All: return Reset; } return Reset; } bool useColoredOutput() { #if defined(_WIN32) if (std::getenv("NO_COLOR") != nullptr) return false; DWORD mode; if (GetConsoleMode(GetStdHandle(STD_ERROR_HANDLE), &mode) && mode & ENABLE_VIRTUAL_TERMINAL_PROCESSING) return true; // some console emulators may not use the Win32 API, so try the Unixy approach return std::getenv("TERM") != nullptr && GetFileType(GetStdHandle(STD_ERROR_HANDLE)) == FILE_TYPE_CHAR; #else return std::getenv("TERM") != nullptr && std::getenv("NO_COLOR") == nullptr && isatty(fileno(stderr)); #endif } class Identity { public: explicit Identity(std::ostream& stream) : mStream(stream) { } void write(const char* str, std::streamsize size, Level /*level*/) { mStream.write(str, size); mStream.flush(); } private: std::ostream& mStream; }; class Coloured { public: explicit Coloured(std::ostream& stream) : mStream(stream) // TODO: check which stream is stderr? , mUseColor(useColoredOutput()) { } void write(const char* str, std::streamsize size, Level level) { if (mUseColor) mStream << "\033[0;" << getColor(level) << 'm'; mStream.write(str, size); if (mUseColor) mStream << "\033[0;" << Reset << 'm'; mStream.flush(); } private: std::ostream& mStream; bool mUseColor; }; class Buffer { public: explicit Buffer(std::size_t capacity, std::deque& buffer) : mCapacity(capacity) , mBuffer(buffer) { } void write(const char* str, std::streamsize size, Level debugLevel) { while (mBuffer.size() >= mCapacity) mBuffer.pop_front(); mBuffer.push_back(Record{ std::string(str, size), debugLevel }); } private: std::size_t mCapacity; std::deque& mBuffer; }; template class Tee : public DebugOutputBase { public: explicit Tee(First first, Second second) : mFirst(first) , mSecond(second) { } std::streamsize writeImpl(const char* str, std::streamsize size, Level debugLevel) override { mFirst.write(str, size, debugLevel); mSecond.write(str, size, debugLevel); return size; } private: First mFirst; Second mSecond; }; } #endif static std::unique_ptr rawStdout = nullptr; static std::unique_ptr rawStderr = nullptr; static std::unique_ptr rawStderrMutex = nullptr; static std::ofstream logfile; #if defined(_WIN32) && defined(_DEBUG) static boost::iostreams::stream_buffer sb; #else static boost::iostreams::stream_buffer> standardOut; static boost::iostreams::stream_buffer> standardErr; static boost::iostreams::stream_buffer> bufferedOut; static boost::iostreams::stream_buffer> bufferedErr; #endif std::ostream& getRawStdout() { return rawStdout ? *rawStdout : std::cout; } std::ostream& getRawStderr() { return rawStderr ? *rawStderr : std::cerr; } Misc::Locked getLockedRawStderr() { return Misc::Locked(*rawStderrMutex, getRawStderr()); } Level getDebugLevel() { if (const char* env = getenv("OPENMW_DEBUG_LEVEL")) { const std::string_view value(env); if (value == "ERROR") return Error; if (value == "WARNING") return Warning; if (value == "INFO") return Info; if (value == "VERBOSE") return Verbose; if (value == "DEBUG") return Debug; } return Verbose; } void setupLogging(const std::filesystem::path& logDir, std::string_view appName) { Log::sMinDebugLevel = getDebugLevel(); Log::sWriteLevel = true; #if !(defined(_WIN32) && defined(_DEBUG)) const std::string logName = Misc::StringUtils::lowerCase(appName) + ".log"; logfile.open(logDir / logName, std::ios::out); Identity log(logfile); for (const Record& v : globalBuffer) log.write(v.mValue.data(), v.mValue.size(), v.mLevel); globalBuffer.clear(); standardOut.open(Tee(log, Coloured(*rawStdout))); standardErr.open(Tee(log, Coloured(*rawStderr))); std::cout.rdbuf(&standardOut); std::cerr.rdbuf(&standardErr); #endif #ifdef _WIN32 if (Crash::CrashCatcher::instance()) { Crash::CrashCatcher::instance()->updateDumpPath(logDir); } #endif } int wrapApplication( int (*innerApplication)(int argc, char* argv[]), int argc, char* argv[], std::string_view appName) { #if defined _WIN32 (void)attachParentConsole(); #endif rawStdout = std::make_unique(std::cout.rdbuf()); rawStderr = std::make_unique(std::cerr.rdbuf()); rawStderrMutex = std::make_unique(); #if defined(_WIN32) && defined(_DEBUG) // Redirect cout and cerr to VS debug output when running in debug mode sb.open(DebugOutput()); std::cout.rdbuf(&sb); std::cerr.rdbuf(&sb); #else constexpr std::size_t bufferCapacity = 1024; bufferedOut.open(Tee(Buffer(bufferCapacity, globalBuffer), Coloured(*rawStdout))); bufferedErr.open(Tee(Buffer(bufferCapacity, globalBuffer), Coloured(*rawStderr))); std::cout.rdbuf(&bufferedOut); std::cerr.rdbuf(&bufferedErr); #endif int ret = 0; try { if (const auto env = std::getenv("OPENMW_DISABLE_CRASH_CATCHER"); env == nullptr || Misc::StringUtils::toNumeric(env, 0) == 0) { #if defined(_WIN32) const std::string crashDumpName = Misc::StringUtils::lowerCase(appName) + "-crash.dmp"; const std::string freezeDumpName = Misc::StringUtils::lowerCase(appName) + "-freeze.dmp"; std::filesystem::path dumpDirectory = std::filesystem::temp_directory_path(); PWSTR userProfile = nullptr; if (SUCCEEDED(SHGetKnownFolderPath(FOLDERID_Profile, 0, nullptr, &userProfile))) { dumpDirectory = userProfile; } CoTaskMemFree(userProfile); Crash::CrashCatcher crashy(argc, argv, dumpDirectory, crashDumpName, freezeDumpName); #else const std::string crashLogName = Misc::StringUtils::lowerCase(appName) + "-crash.log"; // install the crash handler as soon as possible. crashCatcherInstall(argc, argv, std::filesystem::temp_directory_path() / crashLogName); #endif ret = innerApplication(argc, argv); } else ret = innerApplication(argc, argv); } catch (const std::exception& e) { #if (defined(__APPLE__) || defined(__linux) || defined(__unix) || defined(__posix)) if (!isatty(fileno(stdin))) #endif SDL_ShowSimpleMessageBox(0, (std::string(appName) + ": Fatal error").c_str(), e.what(), nullptr); Log(Debug::Error) << "Fatal error: " << e.what(); ret = 1; } // Restore cout and cerr std::cout.rdbuf(rawStdout->rdbuf()); std::cerr.rdbuf(rawStderr->rdbuf()); Log::sMinDebugLevel = All; Log::sWriteLevel = false; return ret; } }