LCOV - code coverage report
Current view: top level - source/ps - CLogger.cpp (source / functions) Hit Total Coverage
Test: 0 A.D. test coverage report Lines: 92 157 58.6 %
Date: 2022-06-14 00:41:00 Functions: 11 16 68.8 %

          Line data    Source code
       1             : /* Copyright (C) 2022 Wildfire Games.
       2             :  * This file is part of 0 A.D.
       3             :  *
       4             :  * 0 A.D. is free software: you can redistribute it and/or modify
       5             :  * it under the terms of the GNU General Public License as published by
       6             :  * the Free Software Foundation, either version 2 of the License, or
       7             :  * (at your option) any later version.
       8             :  *
       9             :  * 0 A.D. is distributed in the hope that it will be useful,
      10             :  * but WITHOUT ANY WARRANTY; without even the implied warranty of
      11             :  * MERCHANTABILITY or FITNESS FOR A PARTICULAR PURPOSE.  See the
      12             :  * GNU General Public License for more details.
      13             :  *
      14             :  * You should have received a copy of the GNU General Public License
      15             :  * along with 0 A.D.  If not, see <http://www.gnu.org/licenses/>.
      16             :  */
      17             : 
      18             : #include "precompiled.h"
      19             : 
      20             : #include "CLogger.h"
      21             : 
      22             : #include "graphics/Canvas2D.h"
      23             : #include "graphics/FontMetrics.h"
      24             : #include "graphics/TextRenderer.h"
      25             : #include "lib/os_path.h"
      26             : #include "lib/timer.h"
      27             : #include "lib/utf8.h"
      28             : #include "ps/CConsole.h"
      29             : #include "ps/CStr.h"
      30             : #include "ps/CStrInternStatic.h"
      31             : #include "ps/Profile.h"
      32             : #include "ps/Pyrogenesis.h"
      33             : 
      34             : #include <ctime>
      35             : #include <fstream>
      36             : #include <iostream>
      37             : 
      38             : #include <boost/algorithm/string/replace.hpp>
      39             : 
      40             : CStrW g_UniqueLogPostfix;
      41             : static const double RENDER_TIMEOUT = 10.0; // seconds before messages are deleted
      42             : static const double RENDER_TIMEOUT_RATE = 10.0; // number of timed-out messages deleted per second
      43             : static const size_t RENDER_LIMIT = 20; // maximum messages on screen at once
      44             : 
      45             : // Set up a default logger that throws everything away, because that's
      46             : // better than crashing. (This is particularly useful for unit tests which
      47             : // don't care about any log output.)
      48             : struct BlackHoleStreamBuf : public std::streambuf
      49             : {
      50             : } blackHoleStreamBuf;
      51             : std::ostream blackHoleStream(&blackHoleStreamBuf);
      52             : CLogger nullLogger(&blackHoleStream, &blackHoleStream, false, true);
      53             : 
      54             : CLogger* g_Logger = &nullLogger;
      55             : 
      56             : const char* html_header0 =
      57             :     "<!DOCTYPE html>\n"
      58             :     "<meta charset=\"utf-8\">\n"
      59             :     "<title>Pyrogenesis Log</title>\n"
      60             :     "<style>"
      61             :     "body { background: #eee; color: black; font-family: sans-serif; } "
      62             :     "p { background: white; margin: 3px 0 3px 0; } "
      63             :     ".error { color: red; } "
      64             :     ".warning { color: blue; }"
      65             :     "</style>\n"
      66             :     "<h2>0 A.D. (";
      67             : 
      68             : const char* html_header1 = "</h2>\n";
      69             : 
      70           0 : CLogger::CLogger()
      71             : {
      72           0 :     OsPath mainlogPath(psLogDir() / (L"mainlog" + g_UniqueLogPostfix + L".html"));
      73           0 :     m_MainLog = new std::ofstream(OsString(mainlogPath).c_str(), std::ofstream::out | std::ofstream::trunc);
      74           0 :     debug_printf("FILES| Main log written to '%s'\n", mainlogPath.string8().c_str());
      75             : 
      76           0 :     OsPath interestinglogPath(psLogDir() / (L"interestinglog" + g_UniqueLogPostfix + L".html"));
      77           0 :     m_InterestingLog = new std::ofstream(OsString(interestinglogPath).c_str(), std::ofstream::out | std::ofstream::trunc);
      78           0 :     debug_printf("FILES| Interesting log written to '%s'\n", interestinglogPath.string8().c_str());
      79             : 
      80           0 :     m_OwnsStreams = true;
      81           0 :     m_UseDebugPrintf = true;
      82             : 
      83           0 :     Init();
      84           0 : }
      85             : 
      86         129 : CLogger::CLogger(std::ostream* mainLog, std::ostream* interestingLog, bool takeOwnership, bool useDebugPrintf)
      87             : {
      88         129 :     m_MainLog = mainLog;
      89         129 :     m_InterestingLog = interestingLog;
      90         129 :     m_OwnsStreams = takeOwnership;
      91         129 :     m_UseDebugPrintf = useDebugPrintf;
      92             : 
      93         129 :     Init();
      94         129 : }
      95             : 
      96         129 : void CLogger::Init()
      97             : {
      98         129 :     m_RenderLastEraseTime = -1.0;
      99             :     // this is called too early to allow us to call timer_Time(),
     100             :     // so we'll fill in the initial value later
     101             : 
     102         129 :     m_NumberOfMessages = 0;
     103         129 :     m_NumberOfErrors = 0;
     104         129 :     m_NumberOfWarnings = 0;
     105             : 
     106         258 :     *m_MainLog << html_header0 << engine_version << ") Main log" << html_header1;
     107         258 :     *m_InterestingLog << html_header0 << engine_version << ") Main log (warnings and errors only)" << html_header1;
     108         129 : }
     109             : 
     110         129 : CLogger::~CLogger()
     111             : {
     112         129 :     char buffer[128];
     113         129 :     sprintf_s(buffer, ARRAY_SIZE(buffer), " with %d message(s), %d error(s) and %d warning(s).", m_NumberOfMessages,m_NumberOfErrors,m_NumberOfWarnings);
     114             : 
     115         129 :     time_t t = time(NULL);
     116         129 :     struct tm* now = localtime(&t);
     117         129 :     char currentDate[17];
     118         129 :     sprintf_s(currentDate, ARRAY_SIZE(currentDate), "%04d-%02d-%02d", 1900+now->tm_year, 1+now->tm_mon, now->tm_mday);
     119         129 :     char currentTime[10];
     120         129 :     sprintf_s(currentTime, ARRAY_SIZE(currentTime), "%02d:%02d:%02d", now->tm_hour, now->tm_min, now->tm_sec);
     121             : 
     122             :     //Write closing text
     123             : 
     124         258 :     *m_MainLog << "<p>Engine exited successfully on " << currentDate;
     125         516 :     *m_MainLog << " at " << currentTime << buffer << "</p>\n";
     126             : 
     127         258 :     *m_InterestingLog << "<p>Engine exited successfully on " << currentDate;
     128         516 :     *m_InterestingLog << " at " << currentTime << buffer << "</p>\n";
     129             : 
     130         129 :     if (m_OwnsStreams)
     131             :     {
     132           3 :         SAFE_DELETE(m_InterestingLog);
     133           3 :         SAFE_DELETE(m_MainLog);
     134             :     }
     135         129 : }
     136             : 
     137         421 : static std::string ToHTML(const char* message)
     138             : {
     139         842 :     std::string cmessage = message;
     140         421 :     boost::algorithm::replace_all(cmessage, "&", "&amp;");
     141         421 :     boost::algorithm::replace_all(cmessage, "<", "&lt;");
     142         421 :     return cmessage;
     143             : }
     144             : 
     145         284 : void CLogger::WriteMessage(const char* message, bool doRender = false)
     146             : {
     147         284 :     std::string cmessage = ToHTML(message);
     148             : 
     149         852 :     std::lock_guard<std::mutex> lock(m_Mutex);
     150             : 
     151         284 :     ++m_NumberOfMessages;
     152             : //  if (m_UseDebugPrintf)
     153             : //      debug_printf("MESSAGE: %s\n", message);
     154             : 
     155         568 :     *m_MainLog << "<p>" << cmessage << "</p>\n";
     156         284 :     m_MainLog->flush();
     157             : 
     158         284 :     if (doRender)
     159             :     {
     160           0 :         if (g_Console) g_Console->InsertMessage(std::string("INFO: ") + message);
     161             : 
     162           0 :         PushRenderMessage(Normal, message);
     163             :     }
     164         284 : }
     165             : 
     166         111 : void CLogger::WriteError(const char* message)
     167             : {
     168         111 :     std::string cmessage = ToHTML(message);
     169             : 
     170         333 :     std::lock_guard<std::mutex> lock(m_Mutex);
     171             : 
     172         111 :     ++m_NumberOfErrors;
     173         111 :     if (m_UseDebugPrintf)
     174           0 :         debug_printf("ERROR: %.16000s\n", message);
     175             : 
     176         111 :     if (g_Console) g_Console->InsertMessage(std::string("ERROR: ") + message);
     177         222 :     *m_InterestingLog << "<p class=\"error\">ERROR: " << cmessage << "</p>\n";
     178         111 :     m_InterestingLog->flush();
     179             : 
     180         222 :     *m_MainLog << "<p class=\"error\">ERROR: " << cmessage << "</p>\n";
     181         111 :     m_MainLog->flush();
     182             : 
     183         111 :     PushRenderMessage(Error, message);
     184         111 : }
     185             : 
     186          26 : void CLogger::WriteWarning(const char* message)
     187             : {
     188          26 :     std::string cmessage = ToHTML(message);
     189             : 
     190          78 :     std::lock_guard<std::mutex> lock(m_Mutex);
     191             : 
     192          26 :     ++m_NumberOfWarnings;
     193          26 :     if (m_UseDebugPrintf)
     194           0 :         debug_printf("WARNING: %s\n", message);
     195             : 
     196          26 :     if (g_Console) g_Console->InsertMessage(std::string("WARNING: ") + message);
     197          52 :     *m_InterestingLog << "<p class=\"warning\">WARNING: " << cmessage << "</p>\n";
     198          26 :     m_InterestingLog->flush();
     199             : 
     200          52 :     *m_MainLog << "<p class=\"warning\">WARNING: " << cmessage << "</p>\n";
     201          26 :     m_MainLog->flush();
     202             : 
     203          26 :     PushRenderMessage(Warning, message);
     204          26 : }
     205             : 
     206           0 : void CLogger::Render(CCanvas2D& canvas)
     207             : {
     208           0 :     PROFILE3_GPU("logger");
     209             : 
     210           0 :     CleanupRenderQueue();
     211             : 
     212           0 :     CStrIntern font_name("mono-stroke-10");
     213           0 :     CFontMetrics font(font_name);
     214           0 :     int lineSpacing = font.GetLineSpacing();
     215             : 
     216           0 :     CTextRenderer textRenderer;
     217           0 :     textRenderer.SetCurrentFont(font_name);
     218           0 :     textRenderer.SetCurrentColor(CColor(1.0f, 1.0f, 1.0f, 1.0f));
     219             : 
     220             :     // Offset by an extra 35px vertically to avoid the top bar.
     221           0 :     textRenderer.Translate(4.0f, 35.0f + lineSpacing);
     222             : 
     223             :     // (Lock must come after loading the CFont, since that might log error messages
     224             :     // and attempt to lock the mutex recursively which is forbidden)
     225           0 :     std::lock_guard<std::mutex> lock(m_Mutex);
     226             : 
     227           0 :     for (const RenderedMessage& msg : m_RenderMessages)
     228             :     {
     229           0 :         const char* type;
     230           0 :         if (msg.method == Normal)
     231             :         {
     232           0 :             type = "info";
     233           0 :             textRenderer.SetCurrentColor(CColor(0.0f, 0.8f, 0.0f, 1.0f));
     234             :         }
     235           0 :         else if (msg.method == Warning)
     236             :         {
     237           0 :             type = "warning";
     238           0 :             textRenderer.SetCurrentColor(CColor(1.0f, 1.0f, 0.0f, 1.0f));
     239             :         }
     240             :         else
     241             :         {
     242           0 :             type = "error";
     243           0 :             textRenderer.SetCurrentColor(CColor(1.0f, 0.0f, 0.0f, 1.0f));
     244             :         }
     245             : 
     246           0 :         const CVector2D savedTranslate = textRenderer.GetTranslate();
     247             : 
     248           0 :         textRenderer.PrintfAdvance(L"[%8.3f] %hs: ", msg.time, type);
     249             :         // Display the actual message in white so it's more readable
     250           0 :         textRenderer.SetCurrentColor(CColor(1.0f, 1.0f, 1.0f, 1.0f));
     251           0 :         textRenderer.Put(0.0f, 0.0f, msg.message.c_str());
     252             : 
     253           0 :         textRenderer.ResetTranslate(savedTranslate);
     254             : 
     255           0 :         textRenderer.Translate(0.0f, (float)lineSpacing);
     256             :     }
     257             : 
     258           0 :     canvas.DrawText(textRenderer);
     259           0 : }
     260             : 
     261         137 : void CLogger::PushRenderMessage(ELogMethod method, const char* message)
     262             : {
     263         137 :     double now = timer_Time();
     264             : 
     265             :     // Add each message line separately
     266         137 :     const char* pos = message;
     267         153 :     const char* eol;
     268         306 :     while ((eol = strchr(pos, '\n')) != NULL)
     269             :     {
     270          16 :         if (eol != pos)
     271             :         {
     272          41 :             RenderedMessage r = { method, now, std::string(pos, eol) };
     273          16 :             m_RenderMessages.push_back(r);
     274             :         }
     275          16 :         pos = eol + 1;
     276             :     }
     277             :     // Add the last line, if we didn't end on a \n
     278         137 :     if (*pos != '\0')
     279             :     {
     280         396 :         RenderedMessage r = { method, now, std::string(pos) };
     281         132 :         m_RenderMessages.push_back(r);
     282             :     }
     283         137 : }
     284             : 
     285           0 : void CLogger::CleanupRenderQueue()
     286             : {
     287           0 :     std::lock_guard<std::mutex> lock(m_Mutex);
     288             : 
     289           0 :     if (m_RenderMessages.empty())
     290           0 :         return;
     291             : 
     292           0 :     double now = timer_Time();
     293             : 
     294             :     // Initialise the timer on the first call (since we can't do it in the ctor)
     295           0 :     if (m_RenderLastEraseTime == -1.0)
     296           0 :         m_RenderLastEraseTime = now;
     297             : 
     298             :     // Delete old messages, approximately at the given rate limit (and at most one per frame)
     299           0 :     if (now - m_RenderLastEraseTime > 1.0/RENDER_TIMEOUT_RATE)
     300             :     {
     301           0 :         if (m_RenderMessages[0].time + RENDER_TIMEOUT < now)
     302             :         {
     303           0 :             m_RenderMessages.pop_front();
     304           0 :             m_RenderLastEraseTime = now;
     305             :         }
     306             :     }
     307             : 
     308             :     // If there's still too many then delete the oldest
     309           0 :     if (m_RenderMessages.size() > RENDER_LIMIT)
     310           0 :         m_RenderMessages.erase(m_RenderMessages.begin(), m_RenderMessages.end() - RENDER_LIMIT);
     311             : }
     312             : 
     313         125 : TestLogger::TestLogger()
     314             : {
     315         125 :     m_OldLogger = g_Logger;
     316         125 :     g_Logger = new CLogger(&m_Stream, &blackHoleStream, false, false);
     317         125 : }
     318             : 
     319         375 : TestLogger::~TestLogger()
     320             : {
     321         125 :     delete g_Logger;
     322         125 :     g_Logger = m_OldLogger;
     323         125 : }
     324             : 
     325          28 : std::string TestLogger::GetOutput()
     326             : {
     327          28 :     return m_Stream.str();
     328             : }
     329             : 
     330           0 : TestStdoutLogger::TestStdoutLogger()
     331             : {
     332           0 :     m_OldLogger = g_Logger;
     333           0 :     g_Logger = new CLogger(&std::cout, &blackHoleStream, false, false);
     334           0 : }
     335             : 
     336           0 : TestStdoutLogger::~TestStdoutLogger()
     337             : {
     338           0 :     delete g_Logger;
     339           0 :     g_Logger = m_OldLogger;
     340           0 : }

Generated by: LCOV version 1.13