/*** Copyright (C) 2022 J Reece Wilson (a/k/a "Reece"). All rights reserved. File: AuLogger.cpp Date: 2022-1-21 Author: Reece ***/ #include #include "AuLogger.hpp" #include #include namespace Aurora::Logging { using namespace Console; static AuList> gLogTasks; static AuThreadPrimitives::MutexSOO gGlobalSpin; static AuThreadPrimitives::MutexSOO gTaskSpin; static AuList gFlushableLoggers; Logger::Logger(const AuList> &sinks) : sinks(sinks) { AuMemset(shouldFilter, 0, sizeof(shouldFilter)); { AU_LOCK_GUARD(gGlobalSpin); SysAssert(AuTryInsert(gFlushableLoggers, this)); } } Logger::~Logger() { Disable(); } void Logger::WriteLines(AuUInt8 uLevel, const ConsoleMessage &msg) { try { if (msg.line.find('\n') == AuString::npos && ((!this->bEnableMitigations) || (msg.line.find('\r') == AuString::npos && msg.line.find('\33') == AuString::npos))) [[likely]] { WriteNowConst(uLevel, msg); } else [[unlikely]] { Parse::SplitNewlines(msg.line, [&](const AuROString &line) { ConsoleMessage dup = msg; dup.line = line; if (WriteNow(uLevel, dup)) { AddToPushQueueConst(uLevel, dup); } }); } } catch (...) { // Loggers experiencing something fucky is a liablity Hooks::WriteLoggerFailedWarning(); } } void Logger::WriteMessage(AuUInt8 uLevel, const ConsoleMessage &msg) { // Accounts for atomic shutdown { AU_LOCK_GUARD(spin); if (shouldFilter[uLevel]) { return; } } WriteLines(uLevel, msg); } bool Logger::ExchangeMitigationState(bool bMitigationsEnabled) { return AuExchange(this->bEnableMitigations, bMitigationsEnabled); } void Logger::AddToPushQueue(AuUInt8 uLevel, /*const*/ ConsoleMessage &msg) { AddToPushQueueConst(uLevel, msg); } void Logger::AddToPushQueueConst(AuUInt8 uLevel, const ConsoleMessage &msg) { { AU_LOCK_GUARD(gTaskSpin); auto nice = gLogTasks.size() + 1; if (gLogTasks.capacity() < nice) { gLogTasks.reserve(nice * 10); } while (!AuTryInsert(gLogTasks, AuMakeTuple(this, uLevel, AuConstReference(msg)))) { SysPushErrorMem("Push failed - trying again"); gTaskSpin->Unlock(); AuThreading::ContextYield(); gTaskSpin->Lock(); } } Grug::DrachenlordScreech(); } void Logger::PushFilter(AuUInt8 uLevel, bool bShouldFilter) { AU_LOCK_GUARD(spin); while (!AuTryInsert(this->filters, AuMakeTuple(uLevel, shouldFilter))) { SysPushErrorMem("Push failed - trying again. wont be able to handle pop - wont syspanic yet"); AuThreading::ContextYield(); } AuMemset(this->shouldFilter, 0, sizeof(this->shouldFilter)); for (auto &tuple : this->filters) { auto uLevel = AuGet<0>(tuple); auto shouldFilter = AuGet<1>(tuple); this->shouldFilter[uLevel] = shouldFilter; } } void Logger::PopFilter() { AU_LOCK_GUARD(this->spin); this->filters.pop_back(); } void ForceFlushLoggers() { AU_DEBUG_MEMCRUNCH; decltype(gLogTasks) logTasks; AU_LOCK_GUARD(gGlobalSpin); { AU_LOCK_GUARD(gTaskSpin); AuSwap(logTasks, gLogTasks); gLogTasks.reserve(12 * 1024); } if (logTasks.empty()) { return; } for (const auto &logEntry : logTasks) { auto &logger = AuGet<0>(logEntry); auto &uLevel = AuGet<1>(logEntry); auto &message = AuGet<2>(logEntry); try { logger->WriteLater(uLevel, message); } catch (...) { } } } void ForceFlushLoggersNoLock() { AU_DEBUG_MEMCRUNCH; decltype(gLogTasks) logTasks; { AuSwap(logTasks, gLogTasks); gLogTasks.reserve(1024); } if (logTasks.empty()) { return; } for (const auto &logEntry : logTasks) { auto &logger = AuGet<0>(logEntry); auto &uLevel = AuGet<1>(logEntry); auto &message = AuGet<2>(logEntry); try { logger->WriteLater(uLevel, message); } catch (...) { } } } static void ForceFlushLogger(Logger *logger) { for (const auto &sink : logger->sinks) { if (!sink) { continue; } try { sink->OnFlush(); } catch (...) { SysPushErrorCatch(); } } } void ForceFlushFlushNoLock() { for (const auto &logger : gFlushableLoggers) { ForceFlushLogger(logger); } } void ForceFlushFlush() { AU_LOCK_GUARD(gGlobalSpin); ForceFlushFlushNoLock(); } void Logger::Disable() { AU_LOCK_GUARD(gGlobalSpin); ForceFlushLoggersNoLock(); ForceFlushLogger(this); { AU_LOCK_GUARD(spin); AuMemset(shouldFilter, 1, sizeof(shouldFilter)); } { AuTryRemove(gFlushableLoggers, this); } } void Logger::WriteNowConst(AuUInt8 uLevel, const ConsoleMessage &msg) { bool bDelegateLater {}; try { for (const auto &sink : this->sinks) { if (!sink) { continue; } try { bDelegateLater |= sink->OnMessageNonblocking(uLevel, msg); } catch (...) { SysPushErrorCatch("Failed to pump a logger"); } } } catch (...) { bDelegateLater = true; SysPushErrorCatch(); } if (bDelegateLater) { AddToPushQueueConst(uLevel, msg); } } bool Logger::WriteNow(AuUInt8 uLevel, ConsoleMessage &msg) { if (this->bEnableMitigations) { // Nuke \r and \x1b / \33 / \e sequences using UTF-8 aware replaceall // \r -> dont let a bad actor override cat and unformatted console logs // \e -> dont let a bad actor communicate with a potentially vulnerable TTY emulator if (msg.line.find('\r') != AuString::npos) [[unlikely]] { AuCodepointsReplaceAll(msg.line, "\r", "\\r"); } if (msg.line.find('\33') != AuString::npos) [[unlikely]] { AuCodepointsReplaceAll(msg.line, "\33", "\\e"); } } bool bDelegateLater {}; try { for (const auto &sink : this->sinks) { if (!sink) { continue; } try { bDelegateLater |= sink->OnMessageNonblocking(uLevel, msg); } catch (...) { SysPushErrorCatch("Failed to pump a logger"); } } } catch (...) { bDelegateLater = true; SysPushErrorCatch(); } return bDelegateLater; } void Logger::WriteLater(AuUInt8 uLevel, const ConsoleMessage &msg) { try { for (const auto &sink : this->sinks) { if (!sink) { continue; } try { sink->OnMessageBlocking(uLevel, msg); } catch (...) { SysPushErrorCatch("Failed to pump a logger"); } } } catch (...) { SysPushErrorCatch(); } } void InitLoggers() { gLogTasks.reserve(1000); } void DeinitLoggers() { ForceFlushLoggers(); gUserLogger.reset(); } AUKN_SYM ILogger *NewLoggerNew(const AuList> &sinks) { try { auto pLogger = _new Logger(sinks); if (!pLogger) { return nullptr; } return pLogger; } catch (...) { SysPushErrorCatch(); return {}; } } AUKN_SYM void NewLoggerRelease(ILogger *pLogger) { AuSafeDelete(pLogger); } }