/* Copyright (C) 2021 Wildfire Games. * This file is part of 0 A.D. * * 0 A.D. is free software: you can redistribute it and/or modify * it under the terms of the GNU General Public License as published by * the Free Software Foundation, either version 2 of the License, or * (at your option) any later version. * * 0 A.D. is distributed in the hope that it will be useful, * but WITHOUT ANY WARRANTY; without even the implied warranty of * MERCHANTABILITY or FITNESS FOR A PARTICULAR PURPOSE. See the * GNU General Public License for more details. * * You should have received a copy of the GNU General Public License * along with 0 A.D. If not, see . */ #include "precompiled.h" #include "CLogger.h" #include "graphics/FontMetrics.h" #include "graphics/ShaderManager.h" #include "graphics/TextRenderer.h" #include "lib/timer.h" #include "lib/utf8.h" #include "ps/CConsole.h" #include "ps/Profile.h" #include "ps/Pyrogenesis.h" #include "renderer/Renderer.h" #include #include #include #include CStrW g_UniqueLogPostfix; static const double RENDER_TIMEOUT = 10.0; // seconds before messages are deleted static const double RENDER_TIMEOUT_RATE = 10.0; // number of timed-out messages deleted per second static const size_t RENDER_LIMIT = 20; // maximum messages on screen at once // Set up a default logger that throws everything away, because that's // better than crashing. (This is particularly useful for unit tests which // don't care about any log output.) struct BlackHoleStreamBuf : public std::streambuf { } blackHoleStreamBuf; std::ostream blackHoleStream(&blackHoleStreamBuf); CLogger nullLogger(&blackHoleStream, &blackHoleStream, false, true); CLogger* g_Logger = &nullLogger; const char* html_header0 = "\n" "\n" "Pyrogenesis Log\n" "\n" "

0 A.D. ("; const char* html_header1 = "

\n"; CLogger::CLogger() { OsPath mainlogPath(psLogDir() / (L"mainlog" + g_UniqueLogPostfix + L".html")); m_MainLog = new std::ofstream(OsString(mainlogPath).c_str(), std::ofstream::out | std::ofstream::trunc); debug_printf("Writing the mainlog at %s\n", mainlogPath.string8().c_str()); OsPath interestinglogPath(psLogDir() / (L"interestinglog" + g_UniqueLogPostfix + L".html")); m_InterestingLog = new std::ofstream(OsString(interestinglogPath).c_str(), std::ofstream::out | std::ofstream::trunc); m_OwnsStreams = true; m_UseDebugPrintf = true; Init(); } CLogger::CLogger(std::ostream* mainLog, std::ostream* interestingLog, bool takeOwnership, bool useDebugPrintf) { m_MainLog = mainLog; m_InterestingLog = interestingLog; m_OwnsStreams = takeOwnership; m_UseDebugPrintf = useDebugPrintf; Init(); } void CLogger::Init() { m_RenderLastEraseTime = -1.0; // this is called too early to allow us to call timer_Time(), // so we'll fill in the initial value later m_NumberOfMessages = 0; m_NumberOfErrors = 0; m_NumberOfWarnings = 0; *m_MainLog << html_header0 << engine_version << ") Main log" << html_header1; *m_InterestingLog << html_header0 << engine_version << ") Main log (warnings and errors only)" << html_header1; } CLogger::~CLogger() { char buffer[128]; sprintf_s(buffer, ARRAY_SIZE(buffer), " with %d message(s), %d error(s) and %d warning(s).", m_NumberOfMessages,m_NumberOfErrors,m_NumberOfWarnings); time_t t = time(NULL); struct tm* now = localtime(&t); char currentDate[17]; sprintf_s(currentDate, ARRAY_SIZE(currentDate), "%04d-%02d-%02d", 1900+now->tm_year, 1+now->tm_mon, now->tm_mday); char currentTime[10]; sprintf_s(currentTime, ARRAY_SIZE(currentTime), "%02d:%02d:%02d", now->tm_hour, now->tm_min, now->tm_sec); //Write closing text *m_MainLog << "

Engine exited successfully on " << currentDate; *m_MainLog << " at " << currentTime << buffer << "

\n"; *m_InterestingLog << "

Engine exited successfully on " << currentDate; *m_InterestingLog << " at " << currentTime << buffer << "

\n"; if (m_OwnsStreams) { SAFE_DELETE(m_InterestingLog); SAFE_DELETE(m_MainLog); } } static std::string ToHTML(const char* message) { std::string cmessage = message; boost::algorithm::replace_all(cmessage, "&", "&"); boost::algorithm::replace_all(cmessage, "<", "<"); return cmessage; } void CLogger::WriteMessage(const char* message, bool doRender = false) { std::string cmessage = ToHTML(message); std::lock_guard lock(m_Mutex); ++m_NumberOfMessages; // if (m_UseDebugPrintf) // debug_printf("MESSAGE: %s\n", message); *m_MainLog << "

" << cmessage << "

\n"; m_MainLog->flush(); if (doRender) { if (g_Console) g_Console->InsertMessage(std::string("INFO: ") + message); PushRenderMessage(Normal, message); } } void CLogger::WriteError(const char* message) { std::string cmessage = ToHTML(message); std::lock_guard lock(m_Mutex); ++m_NumberOfErrors; if (m_UseDebugPrintf) debug_printf("ERROR: %.16000s\n", message); if (g_Console) g_Console->InsertMessage(std::string("ERROR: ") + message); *m_InterestingLog << "

ERROR: " << cmessage << "

\n"; m_InterestingLog->flush(); *m_MainLog << "

ERROR: " << cmessage << "

\n"; m_MainLog->flush(); PushRenderMessage(Error, message); } void CLogger::WriteWarning(const char* message) { std::string cmessage = ToHTML(message); std::lock_guard lock(m_Mutex); ++m_NumberOfWarnings; if (m_UseDebugPrintf) debug_printf("WARNING: %s\n", message); if (g_Console) g_Console->InsertMessage(std::string("WARNING: ") + message); *m_InterestingLog << "

WARNING: " << cmessage << "

\n"; m_InterestingLog->flush(); *m_MainLog << "

WARNING: " << cmessage << "

\n"; m_MainLog->flush(); PushRenderMessage(Warning, message); } void CLogger::Render() { PROFILE3_GPU("logger"); CleanupRenderQueue(); CStrIntern font_name("mono-stroke-10"); CFontMetrics font(font_name); int lineSpacing = font.GetLineSpacing(); CShaderTechniquePtr textTech = g_Renderer.GetShaderManager().LoadEffect(str_gui_text); textTech->BeginPass(); CTextRenderer textRenderer(textTech->GetShader()); textRenderer.Font(font_name); textRenderer.Color(1.0f, 1.0f, 1.0f); // Offset by an extra 35px vertically to avoid the top bar. textRenderer.Translate(4.0f, 35.0f + lineSpacing, 0.0f); // (Lock must come after loading the CFont, since that might log error messages // and attempt to lock the mutex recursively which is forbidden) std::lock_guard lock(m_Mutex); for (const RenderedMessage& msg : m_RenderMessages) { const char* type; if (msg.method == Normal) { type = "info"; textRenderer.Color(0.0f, 0.8f, 0.0f); } else if (msg.method == Warning) { type = "warning"; textRenderer.Color(1.0f, 1.0f, 0.0f); } else { type = "error"; textRenderer.Color(1.0f, 0.0f, 0.0f); } CMatrix3D savedTransform = textRenderer.GetTransform(); textRenderer.PrintfAdvance(L"[%8.3f] %hs: ", msg.time, type); // Display the actual message in white so it's more readable textRenderer.Color(1.0f, 1.0f, 1.0f); textRenderer.Put(0.0f, 0.0f, msg.message.c_str()); textRenderer.SetTransform(savedTransform); textRenderer.Translate(0.0f, (float)lineSpacing, 0.0f); } textRenderer.Render(); textTech->EndPass(); } void CLogger::PushRenderMessage(ELogMethod method, const char* message) { double now = timer_Time(); // Add each message line separately const char* pos = message; const char* eol; while ((eol = strchr(pos, '\n')) != NULL) { if (eol != pos) { RenderedMessage r = { method, now, std::string(pos, eol) }; m_RenderMessages.push_back(r); } pos = eol + 1; } // Add the last line, if we didn't end on a \n if (*pos != '\0') { RenderedMessage r = { method, now, std::string(pos) }; m_RenderMessages.push_back(r); } } void CLogger::CleanupRenderQueue() { std::lock_guard lock(m_Mutex); if (m_RenderMessages.empty()) return; double now = timer_Time(); // Initialise the timer on the first call (since we can't do it in the ctor) if (m_RenderLastEraseTime == -1.0) m_RenderLastEraseTime = now; // Delete old messages, approximately at the given rate limit (and at most one per frame) if (now - m_RenderLastEraseTime > 1.0/RENDER_TIMEOUT_RATE) { if (m_RenderMessages[0].time + RENDER_TIMEOUT < now) { m_RenderMessages.pop_front(); m_RenderLastEraseTime = now; } } // If there's still too many then delete the oldest if (m_RenderMessages.size() > RENDER_LIMIT) m_RenderMessages.erase(m_RenderMessages.begin(), m_RenderMessages.end() - RENDER_LIMIT); } TestLogger::TestLogger() { m_OldLogger = g_Logger; g_Logger = new CLogger(&m_Stream, &blackHoleStream, false, false); } TestLogger::~TestLogger() { delete g_Logger; g_Logger = m_OldLogger; } std::string TestLogger::GetOutput() { return m_Stream.str(); } TestStdoutLogger::TestStdoutLogger() { m_OldLogger = g_Logger; g_Logger = new CLogger(&std::cout, &blackHoleStream, false, false); } TestStdoutLogger::~TestStdoutLogger() { delete g_Logger; g_Logger = m_OldLogger; }